Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add snailtracer benchmark #2

Merged
merged 4 commits into from
Oct 2, 2022
Merged

Add snailtracer benchmark #2

merged 4 commits into from
Oct 2, 2022

Conversation

ziyadedher
Copy link
Contributor

Note: this PR includes #1 cuz it made it easier

Did some benchmarking using snailtracer -- results are pretty good IMO:

~50ms using revm, ~113ms using pyrevm, eh not bad. I expected it to be a bit closer, but I imagine a good portion of this is Python FFI overhead. Haven't dug into it too much.

This isn't a perfect apples-to-apples comparison, the revm benchmark modifies the transaction context before starting the benchmark, this benchmark constructions the environment during the benchmark. With a little more effort we could probably remove any additional overhead due to that, but I don't think it's that big of a deal.


Baseline results using the snailtracer benchmark from revm:

Hello, world!
elapsed: 49.963531ms
0: 63.562866ms
1: 61.138572ms
2: 55.771676ms
3: 49.228193ms
4: 49.100465ms
5: 48.995046ms
6: 48.847959ms
7: 48.743462ms
8: 48.731132ms
9: 48.718941ms
10: 48.71229ms
11: 48.696701ms
12: 48.694723ms
13: 48.671922ms
14: 48.65721ms
15: 48.611618ms
16: 48.610157ms
17: 48.547279ms
18: 48.50588ms
19: 48.456446ms
20: 48.451354ms
21: 48.449931ms
22: 48.373144ms
23: 48.316536ms
24: 48.315507ms
end!

Results from this benchmark:

         21 function calls in 1.135 seconds

   Ordered by: cumulative time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
       10    0.000    0.000    1.135    0.113 /home/ziyadedher/code/eth/pyrevm/bench/snailtracer/snailtracer.py:39(bench)
       10    1.135    0.113    1.135    0.113 {method 'call_raw' of 'builtins.EVM' objects}
        1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}

Copy link
Member

@gakonst gakonst left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

sweet! do we know how fast pyevm is?

@gakonst gakonst merged commit 32f0aaf into paradigmxyz:master Oct 2, 2022
@ziyadedher
Copy link
Contributor Author

Huh... I completely forgot about the existence of pyevm lol. Lemme see if I can get this benchmark running there.

@ziyadedher ziyadedher deleted the ziyadedher/bench branch October 3, 2022 00:45
@ziyadedher
Copy link
Contributor Author

ziyadedher commented Oct 3, 2022

Let's just say... slower. Average of ~39028ms per run. That's about 345x slower, wow. I tried to get the benchmark as barebones as possible, I think I actually trimmed it more than the benchmark for pyrevm, if you can spot anything that would be causing such a huge slowdown, let me know: https://gist.github.com/ziyadedher/d07610ad172cf25fff7d0558c522304d

But it does seem like the majority of time is spent evaluating opcodes according to the profile below.

   Ordered by: cumulative time
   List reduced from 244 to 10 due to restriction <10>

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        5    0.000    0.000  195.138   39.028 /home/ziyadedher/code/eth/pyrevm/bench/snailtracer/snailtracer-pyevm.py:81(bench)
        5    0.000    0.000  195.138   39.028 /home/ziyadedher/code/eth/pyrevm/.venv/lib/python3.10/site-packages/eth/vm/forks/berlin/state.py:20(build_computation)
        5    0.000    0.000  195.137   39.027 /home/ziyadedher/code/eth/pyrevm/.venv/lib/python3.10/site-packages/eth/vm/forks/frontier/state.py:112(build_computation)
        5    0.000    0.000  195.137   39.027 /home/ziyadedher/code/eth/pyrevm/.venv/lib/python3.10/site-packages/eth/vm/forks/frontier/computation.py:51(apply_message)
        5   18.656    3.731  195.137   39.027 /home/ziyadedher/code/eth/pyrevm/.venv/lib/python3.10/site-packages/eth/vm/computation.py:518(apply_computation)
 40571945   21.021    0.000  156.979    0.000 /home/ziyadedher/code/eth/pyrevm/.venv/lib/python3.10/site-packages/eth/vm/opcode.py:45(wrapped_logic_fn)
  1644380    2.301    0.000   31.413    0.000 /home/ziyadedher/code/eth/pyrevm/.venv/lib/python3.10/site-packages/eth/vm/logic/memory.py:4(mstore)
  3247640    7.757    0.000   25.036    0.000 /home/ziyadedher/code/eth/pyrevm/.venv/lib/python3.10/site-packages/eth/vm/computation.py:202(extend_memory)
 41098595   10.474    0.000   23.449    0.000 /home/ziyadedher/code/eth/pyrevm/.venv/lib/python3.10/site-packages/eth/vm/computation.py:251(consume_gas)
  8607700   10.600    0.000   15.642    0.000 /home/ziyadedher/code/eth/pyrevm/.venv/lib/python3.10/site-packages/eth/vm/stack.py:135(pop_ints)

@gakonst
Copy link
Member

gakonst commented Oct 3, 2022

Suspect there's a lot of overhead due to pyevm doing header validation, vs just being a thin interpreter

@ziyadedher
Copy link
Contributor Author

ziyadedher commented Oct 8, 2022

I did some pruning and (1) verified no header validation is being done and (2) no state is being committed in the critical paths for the pyevm benchmarks. Traced the code line-by-line and AFAICT it's just straight up transaction execution, running opcodes. I even got rid of the profiler in case that had some overhead.

I end up with ~15693ms per run of this benchmark compared to ~115ms for pyrevm under the same harness. That's ~135x faster. Incredible. I don't see any reason to doubt this right now, but happy to be proved wrong.

@gakonst
Copy link
Member

gakonst commented Oct 8, 2022

Wow that's wild, thank you for running this. Any way to reproduce the result with your pruned pyevm?

@ziyadedher
Copy link
Contributor Author

ziyadedher commented Oct 8, 2022

Removed the profiler from the pyevm benchmark and updated the gist here: https://gist.github.com/ziyadedher/d07610ad172cf25fff7d0558c522304d

I just mocked out the StateAPI, basically commenting out all the DB functionality in eth/vm/state.py. I don't think this did much actually, disabling profiling seems to have had the largest effect. There actually isn't much going on in the critical path (other than layers and layers of abstractions).

In the gist, here's how the control flow goes. There's a lot of weird overriding and inheritance going on that makes it hard to manually trace:

If someone wants to repro, I'd encourage mocking out the StateAPI to start, but also challenging some of the assumptions I made here about what's expensive and what's not. But the profiler output seems to corroborate those assumptions.


Here's some profiler output. Note the walltimes are not true-to-life since the profiler adds significant overhead, but it gives a sense.

         576141973 function calls (566809707 primitive calls) in 203.218 seconds

   Ordered by: internal time
   List reduced from 299 to 25 due to restriction <25>

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
 40571945   22.187    0.000  163.158    0.000 /home/ziyadedher/code/eth/pyrevm/.venv/lib/python3.10/site-packages/eth/vm/opcode.py:45(wrapped_logic_fn)
        5   19.798    3.960  203.217   40.643 /home/ziyadedher/code/eth/pyrevm/.venv/lib/python3.10/site-packages/eth/vm/computation.py:518(apply_computation)
 42172966   13.622    0.000   13.622    0.000 /home/ziyadedher/code/eth/pyrevm/.venv/lib/python3.10/site-packages/eth/vm/gas_meter.py:55(consume_gas)
  8607700   11.114    0.000   16.160    0.000 /home/ziyadedher/code/eth/pyrevm/.venv/lib/python3.10/site-packages/eth/vm/stack.py:135(pop_ints)
 41098906   10.584    0.000   23.842    0.000 /home/ziyadedher/code/eth/pyrevm/.venv/lib/python3.10/site-packages/eth/vm/computation.py:251(consume_gas)
 41070870    9.378    0.000    9.378    0.000 /home/ziyadedher/code/eth/pyrevm/.venv/lib/python3.10/site-packages/eth/vm/code_stream.py:47(__iter__)
  3247640    7.866    0.000   25.434    0.000 /home/ziyadedher/code/eth/pyrevm/.venv/lib/python3.10/site-packages/eth/vm/computation.py:202(extend_memory)
73628592/64414867    6.655    0.000    8.257    0.000 {built-in method builtins.len}
  1644380    6.501    0.000   11.223    0.000 /home/ziyadedher/code/eth/pyrevm/.venv/lib/python3.10/site-packages/eth/vm/memory.py:47(write)
  7283285    5.187    0.000   14.431    0.000 /home/ziyadedher/code/eth/pyrevm/.venv/lib/python3.10/site-packages/eth/vm/logic/stack.py:10(push_XX)
  8886545    4.635    0.000    8.180    0.000 /home/ziyadedher/code/eth/pyrevm/.venv/lib/python3.10/site-packages/eth/vm/stack.py:65(push_bytes)
 10408480    4.573    0.000    5.943    0.000 /home/ziyadedher/code/eth/pyrevm/.venv/lib/python3.10/site-packages/eth/vm/stack.py:203(dup)
  6495280    4.405    0.000    5.132    0.000 /home/ziyadedher/code/eth/pyrevm/.venv/lib/python3.10/site-packages/eth/vm/computation.py:85(memory_gas_cost)
  7760025    4.002    0.000    6.199    0.000 /home/ziyadedher/code/eth/pyrevm/.venv/lib/python3.10/site-packages/eth/vm/stack.py:57(push_int)
 10302555    3.749    0.000    5.512    0.000 /home/ziyadedher/code/eth/pyrevm/.venv/lib/python3.10/site-packages/eth/validation.py:160(validate_uint256)
 12851413    3.152    0.000    4.485    0.000 /home/ziyadedher/code/eth/pyrevm/.venv/lib/python3.10/site-packages/eth_utils/encoding.py:5(big_endian_to_int)
 10408480    3.033    0.000    8.976    0.000 /home/ziyadedher/code/eth/pyrevm/.venv/lib/python3.10/site-packages/eth/vm/computation.py:287(stack_dup)
 44270476    2.892    0.000    2.892    0.000 {method 'append' of 'list' objects}
 10408480    2.746    0.000   11.722    0.000 /home/ziyadedher/code/eth/pyrevm/.venv/lib/python3.10/site-packages/eth/vm/logic/duplication.py:6(dup_XX)
  3431640    2.737    0.000   12.665    0.000 /home/ziyadedher/code/eth/pyrevm/.venv/lib/python3.10/site-packages/eth/vm/logic/arithmetic.py:16(add)
  3247640    2.671    0.000    5.694    0.000 /home/ziyadedher/code/eth/pyrevm/.venv/lib/python3.10/site-packages/eth/vm/memory.py:24(extend)
  5905345    2.584    0.000    4.102    0.000 /home/ziyadedher/code/eth/pyrevm/.venv/lib/python3.10/site-packages/eth/vm/stack.py:90(pop1_int)
  1644380    2.507    0.000   32.195    0.000 /home/ziyadedher/code/eth/pyrevm/.venv/lib/python3.10/site-packages/eth/vm/logic/memory.py:4(mstore)
  1291570    2.374    0.000    5.899    0.000 /home/ziyadedher/code/eth/pyrevm/.venv/lib/python3.10/site-packages/eth/vm/logic/arithmetic.py:123(sdiv)
 26973660    2.330    0.000    2.547    0.000 {built-in method builtins.isinstance}

@gakonst
Copy link
Member

gakonst commented Oct 8, 2022

This is great. Appreciate you taking the time to note everything down.

@ziyadedher
Copy link
Contributor Author

ziyadedher commented Oct 8, 2022

@SamWilsn recommended trying w/ PyPy, it's a lot faster! ~4290ms per run w/ PyPy compared to ~15693ms w/ CPython. So pyrevm is "only" 37x faster than pyevm running in PyPy.

Below is a summary of results so far. This is on a i7-7700K CPU @ 4.20GHz.

Runtime Average time per snailtracer run (ms) Relative time
revm, rustc 1.64.0 ~50 x0.434
pyrevm, rustc 1.64.0, cpython 3.10.7 ~115 x1.00
py-evm, pypy 7.3.9 (python 3.9.12) ~4290 x37.3
py-evm, cpython 3.10.7 ~15693 x136

Below is a profile from the PyPy run, again walltimes are misleading.

37681231/37674390    3.719    0.000    6.348    0.000 /opt/pypy3/lib/pypy3.9/_functools.py:78(__call__)
  6495280    3.402    0.000    4.074    0.000 /home/ziyadedher/code/eth/pyrevm/.venv/lib/pypy3.9/site-packages/eth/vm/computation.py:85(memory_gas_cost)
        5    3.388    0.678   32.348    6.470 /home/ziyadedher/code/eth/pyrevm/.venv/lib/pypy3.9/site-packages/eth/vm/computation.py:518(apply_computation)
  8607700    2.864    0.000    4.132    0.000 /home/ziyadedher/code/eth/pyrevm/.venv/lib/pypy3.9/site-packages/eth/vm/stack.py:135(pop_ints)
  1644380    1.323    0.000    1.669    0.000 /home/ziyadedher/code/eth/pyrevm/.venv/lib/pypy3.9/site-packages/eth/vm/memory.py:47(write)
 40571945    1.321    0.000   26.100    0.000 /home/ziyadedher/code/eth/pyrevm/.venv/lib/pypy3.9/site-packages/eth/vm/opcode.py:45(wrapped_logic_fn)
  3247640    1.320    0.000    7.741    0.000 /home/ziyadedher/code/eth/pyrevm/.venv/lib/pypy3.9/site-packages/eth/vm/computation.py:202(extend_memory)
 12851413    0.861    0.000    0.861    0.000 {method 'from_bytes' of 'type' objects}
 41098906    0.853    0.000    1.580    0.000 /home/ziyadedher/code/eth/pyrevm/.venv/lib/pypy3.9/site-packages/eth/vm/computation.py:251(consume_gas)
 42172966    0.788    0.000    0.788    0.000 /home/ziyadedher/code/eth/pyrevm/.venv/lib/pypy3.9/site-packages/eth/vm/gas_meter.py:55(consume_gas)
  1644380    0.725    0.000    7.701    0.000 /home/ziyadedher/code/eth/pyrevm/.venv/lib/pypy3.9/site-packages/eth/vm/logic/memory.py:4(mstore)
73628617/64414892    0.604    0.000    0.737    0.000 {built-in function len}
 44270476    0.595    0.000    0.595    0.000 {method 'append' of 'list' objects}
 41070865    0.511    0.000    0.511    0.000 /home/ziyadedher/code/eth/pyrevm/.venv/lib/pypy3.9/site-packages/eth/vm/code_stream.py:47(__iter__)
  3431640    0.396    0.000    2.351    0.000 /home/ziyadedher/code/eth/pyrevm/.venv/lib/pypy3.9/site-packages/eth/vm/logic/arithmetic.py:16(add)
  1644380    0.385    0.000    2.054    0.000 /home/ziyadedher/code/eth/pyrevm/.venv/lib/pypy3.9/site-packages/eth/vm/computation.py:236(memory_write)
  1291570    0.376    0.000    1.103    0.000 /home/ziyadedher/code/eth/pyrevm/.venv/lib/pypy3.9/site-packages/eth/vm/logic/arithmetic.py:123(sdiv)
  7760025    0.353    0.000    0.575    0.000 /home/ziyadedher/code/eth/pyrevm/.venv/lib/pypy3.9/site-packages/eth/vm/stack.py:57(push_int)
  1074060    0.350    0.000    0.350    0.000 {method 'extend' of 'bytearray' objects}
  8886545    0.349    0.000    0.706    0.000 /home/ziyadedher/code/eth/pyrevm/.venv/lib/pypy3.9/site-packages/eth/vm/stack.py:65(push_bytes)
 10302555    0.317    0.000    0.454    0.000 /home/ziyadedher/code/eth/pyrevm/.venv/lib/pypy3.9/site-packages/eth/validation.py:160(validate_uint256)
 16265935    0.310    0.000    0.310    0.000 /home/ziyadedher/code/eth/pyrevm/.venv/lib/pypy3.9/site-packages/eth/_utils/numeric.py:39(ceilXX)
   382678    0.304    0.000    0.592    0.000 /home/ziyadedher/code/eth/pyrevm/.venv/lib/pypy3.9/site-packages/rlp/codec.py:244(decode)
 12851413    0.251    0.000    1.112    0.000 /home/ziyadedher/code/eth/pyrevm/.venv/lib/pypy3.9/site-packages/eth_utils/encoding.py:5(big_endian_to_int)
  7283285    0.239    0.000    0.821    0.000 /home/ziyadedher/code/eth/pyrevm/.venv/lib/pypy3.9/site-packages/eth/vm/logic/stack.py:10(push_XX)

@ziyadedher
Copy link
Contributor Author

BTW I threw together https://github.com/ziyadedher/evm-bench, here's how pyrevm compares on a few different benchmarks against friends. I'll probably get geth in there at some point too.

py-evm.cpython py-evm.pypy pyrevm revm
erc20.approval-transfer 1.4258s 377.2ms 16.8ms 10ms
erc20.mint 1.4092s 347.8ms 14.4ms 5.6ms
erc20.transfer 1.9988s 420.8ms 22.6ms 11.4ms
snailtracer 17.857s 5.17s 138ms 58ms
ten-thousand-hashes 3.4344s 665.6ms 18.2ms 7ms
sum 26.1252s 6.9814s 210ms 92ms
relative 124x 33.2x 1.00x 0.44x

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants